Repository navigation
fix: correct terminal telemetry status and timing - #865
zhongkechen wants to merge 7 commits into
Conversation
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
Normalize terminal timestamps in lifecycle handlers so exception events and span ends use the same value. Require an explicit exception timestamp and remove error plumbing and the duplicate equal-time adjustment. Keep ordered fallback timestamps for invocation cleanup. Cover cleanup when an incomplete attempt starts ahead of the local clock, and verify that the new regression rejects removal of the fallback.
![github-actions[bot]](https://avatars.githubusercontent.com/in/15368?s=60&v=4){kind=small}
This comment has been minimized.
This comment has been minimized.
Check exact normalized durable ends for operations and attempts, including equal, reversed, and missing start times. Bound fallback ends by the callback clock only when the durable end is absent. Keep exception/end agreement assertions and verify that forcing wall-clock time or removing the clock fallback is rejected in each handler. Addresses review comment r4417357787.
Codex AI reviewNo actionable findings after reviewing all seven changed files against rules 1–9. The strengthened timestamp assertions address the prior finding. Tests were inspected but not executed; deployed Lambda/backend behavior remains unverified. Reviewed commit |
| elif info.status in { | ||
| OperationStatus.FAILED, | ||
| OperationStatus.TIMED_OUT, | ||
| OperationStatus.STOPPED, | ||
| }: | ||
| span.set_status(StatusCode.ERROR) |
There was a problem hiding this comment.
Both views now contain the same three-branch status mapping. PR #752: correct exported status mappings changed it in both views, and this PR changes both again. JS keeps the mapping in one function, setOperationSpanStatus. Java does the same with applyOperationStatus. Can both views call one shared function, so the next change edits one place?
_FAILURE_STATUSES = frozenset(
{OperationStatus.FAILED, OperationStatus.TIMED_OUT, OperationStatus.STOPPED}
)
def set_operation_span_status(span: Span, info: OperationEndInfo) -> None:
if info.error:
span.set_status(StatusCode.ERROR, info.error.message or "")
elif info.status in _FAILURE_STATUSES:
span.set_status(StatusCode.ERROR)
elif info.status is OperationStatus.SUCCEEDED:
span.set_status(StatusCode.OK)| Terminal operation and attempt exception events use the same normalized end | ||
| timestamp as their span, including delayed or replayed completion delivery. | ||
| Execution view retains durable timing and normalizes an end at or before its | ||
| start; Invocation view retains its invocation-local timestamp ordering. A | ||
| checkpointless context with no durable start uses its completion time as the | ||
| lower bound in Execution view. When an end timestamp is absent, the current time | ||
| is chosen once for both the event and span end. |
There was a problem hiding this comment.
The paragraph uses "normalized" and "invocation-local timestamp ordering" without defining them. The checkpointless sentence also does not match the runner. In Execution view, a virtual child that sleeps 50 ms exports a 50 ms span. So its span starts when the user function starts, not at completion. Can the paragraph state the rules directly and drop that sentence? For example:
An operation or attempt exception event has the same timestamp as its span
end. This holds for late and replayed completions too.
Execution view uses the durable end time, or a later child span's end. An end
at or before the start moves to 1 µs after the start.
Invocation view keeps timestamps in order within an invocation. An end that is
not after the last timestamp it used moves to 1 µs after that timestamp.
Without an end time, the view reads the clock once for the event and the span
end.| expected = ( | ||
| StatusCode.ERROR | ||
| if with_error | ||
| or status | ||
| in {OperationStatus.FAILED, OperationStatus.TIMED_OUT, OperationStatus.STOPPED} | ||
| else ( | ||
| StatusCode.OK if status is OperationStatus.SUCCEEDED else StatusCode.UNSET | ||
| ) |
There was a problem hiding this comment.
This expectation recomputes the production rule. So a wrong rule in the plugin and the same rule here pass together. A literal table avoids that. It also fails with KeyError when OperationStatus gains a member. Can the expectation be a table? This one is optional.
_STATUS_WITHOUT_ERROR: dict[OperationStatus, StatusCode] = {
OperationStatus.STARTED: StatusCode.UNSET,
OperationStatus.PENDING: StatusCode.UNSET,
OperationStatus.READY: StatusCode.UNSET,
OperationStatus.SUCCEEDED: StatusCode.OK,
OperationStatus.FAILED: StatusCode.ERROR,
OperationStatus.CANCELLED: StatusCode.UNSET,
OperationStatus.TIMED_OUT: StatusCode.ERROR,
OperationStatus.STOPPED: StatusCode.ERROR,
}
expected = StatusCode.ERROR if with_error else _STATUS_WITHOUT_ERROR[status]
Issue #, if available
Fixes #853.
Description of changes
Operations ending FAILED, TIMED_OUT, or STOPPED without diagnostic details now
produce ERROR spans in both OTel views. Supplied operation and attempt exceptions
are recorded at the same normalized timestamp used to end their span, so delayed
completion delivery cannot put the event after the span. A failed attempt without
diagnostics does not fabricate an exception event.
CANCELLED without an error remains UNSET, RETRY remains RETRYING/UNSET, and a caught
operation failure does not make a successful Invocation or Workflow span fail.
Existing exception type/message/stack preservation is retained. The README
documents the refined status mapping and timing behavior.
Design
are unchanged. The issue specifies the refined telemetry outcome contract.
once and pass the same integer to exception recording and span completion.
Invocation view's
_end_spanonly unregisters/ends the span and chooses anordered time when cleanup callers omit it. This removes error plumbing, the
repeated failed-outcome check, and the duplicate equal-time adjustment.
The exception recorder requires
timestamp: int; each view retains itsexisting normalization policy. Changing status alone would leave exception
events outside delayed spans; a shared finalizer would mix the two timing
policies.
recording independently chose the current clock while span completion used
durable or invocation-normalized time. The exception helper also synthesized
diagnostics for errorless failed attempts.
members or configuration options.
timing. Keep the implementation and assert explicit expected durable ends
for operation and attempt spans. Only absent ends use callback wall-clock
bounds. No production-code change is needed for this review finding.
Validation
120 passed in the focused status/timing and public-handler suite. Failures
demonstrate missing ERROR status, fabricated events for errorless attempts,
and exception events differing from or falling after their span end.
and their expectations are retained.
hatch run dev-otel:test -qq --tb=short: 874 passed.hatch run dev-otel:typecheck: no issues in 45 source files.hatch fmt --check: passed.hatch build: passed.hatch run test-wheel-otel:test -qq --tb=short: 874 OTel tests and12 lifecycle tests passed.
test_invocation_cleanup_keeps_future_attempt_bounded: invocationcleanup must end an incomplete attempt after its start even when the start
is ahead of the local clock. It passes with the fix and fails when the
missing-timestamp normalization branch is removed.
installed source bytes and artifact hashes.
test_terminal_exception_uses_normalized_span_endandtest_failed_attempt_exception_uses_normalized_span_endwith exact expectedExecution-view ends, including equal/reversed times and checkpointless
contexts. Missing-end cases assert callback-before <= end <= callback-after;
attempt timing is checked with and without diagnostics. Existing event/end
equality and bounds assertions remain.
forced to use the clock. The new 32 cases pass unchanged production code.
Independently forcing the clock now fails four operation cases and six
attempt cases. Removing the clock fallback fails the missing-end cases in
each handler. All four mutations were rejected and then restored.
verified against the unchanged production sources before rerunning the
complete wheel suite.
The public-handler tests cover caught checkpointed child, virtual child, and
chained-invoke failures, with and without a durable wait/replay. They assert
successful Invocation/Workflow status, bounded events, saved step execution
exactly once, and reuse of stored nonvirtual failure outcomes.
Existing expectation change:
test_operation_status_and_exceptionnow expectsERROR, rather than UNSET, for FAILED/TIMED_OUT/STOPPED without an error. It still
requires no exception event and preserves the original durable status attribute.
The matrix is expanded to include STARTED/PENDING/READY controls. Other added
tests do not replace existing behavioral expectations.
Prior CI results
All four ADOT/X-Ray and Community/S3 jobs
each reported 19 passing cases, case 11 failing, and seven uncovered requirements.
The exact same case-11 history mismatch and counts occur on
main at d7ae955.
The handler/coverage repair remains #864/#796; this PR does not claim case-25
cloud qualification.
The cloud-example workflow
failed in Python 3.11/3.13 because
GetDurableExecutionHistorywas throttled afterfour retries. The affected handlers have no OTel plugin and their polling code is
unchanged. Python 3.12/3.14 passed. No #853-caused regression was found in these
failures.
Prior combined local validation of all six scoped fixes passed 5,058
core/OTel/testing tests. Merge coordination for the shared terminal renderers is recorded in #869.
Assumptions
ERROR while the caught workflow succeeds; see the
shared execution requirement.
SimpleSpanProcessor, and InMemorySpanExporter in both views.
remains in test(otel): cover replay and chained execution #796. No conformance requirement or handler is changed.
Decisions not covered by the issue or the design note
_end_spanaccepts normalized nanoseconds. Suppliedtimestamps pass through unchanged; cleanup without a timestamp still uses
_next_ordered_timestamp()to preserve invocation ordering.only absence of the error object suppresses the event. Empty callback error
normalization remains in [Testing]: Preserve empty callback error history without changing runtime errors #862.
Checklist
By submitting this pull request, I confirm that you can use, modify, copy, and
redistribute this contribution, under the terms of your choice.